[STACKED on #968] fix(vmm): bound the logs a CVM writes within a boot - #970
Merged
Conversation
This was referenced Jul 31, 2026
kvinwang
force-pushed
the
codex/fix-vmm-serial-log-cap
branch
from
August 6, 2026 03:23
93b8593 to
4ff2c0c
Compare
kvinwang
force-pushed
the
codex/fix-vmm-serial-log-cap
branch
4 times, most recently
from
August 6, 2026 09:10
0710f7a to
e4749eb
Compare
QEMU appends to serial.log for the whole life of a boot and offers no way to bound it. A chatty or malicious guest could fill the host disk, and the next boot's archiving step read the entire file into memory in one allocation. The symptom this branch started from — trimming discarded the boot delimiter along with older output — only existed because several boots shared one capped archive file and the delimiter had to be recovered from the log text. Bounding a boot removes that condition, so this addresses the cause instead. QEMU cannot do it for us. The QAPI schema for the file and pty chardev backends exposes only out/in/append plus the generic logfile/logappend, none of which is a size limit; the one `size` knob in the chardev family belongs to `ringbuf`, an in-memory ring rather than a file. libvirt hit the same wall and answered it with a separate daemon, virtlogd. So bound it outside QEMU. Rotation lives in `logrotate`, which works on a path and knows nothing about serial logs — the same way logrotate(8) does not care what it is rotating. `<path>.N-1` becomes `<path>.N`, the live file is archived as `<path>.1`, and the oldest segment is discarded. A VM start is simply another rotation trigger, so the previous boot is preserved as serial.log.1 and boot boundaries land on segment boundaries. Only two things stay serial-specific: which file to rotate, and the eligibility check below. Retention is configured under `[cvm.log]` as `max_bytes`, `max_backups` and `check_interval_secs`, named for the mechanism rather than for serial because stdout and stderr use the same section. All three logs are rotated, but they are not gated alike. stdout and stderr are written by the supervisor, which always opens them with append(true) and already reopens them when they change — its own comment calls that "logrotate detection" — so they satisfy the contract no matter which VMM launched the VM, and keep their cap across a VMM upgrade. serial.log is written by QEMU and is included only when its annotation confirms logappend=on. The values live in the shipped vmm.toml rather than in serde defaults, which means the defaults are themselves parsed on every load. That is not cosmetic: the doc comment inherited from serial_history_max_bytes advertised sizes like "4MB", which size_parser does not accept — a serde default had been hiding the fact that anyone following that comment would have failed to start the VMM. Three details carry the design. `logappend=on` is now passed to the chardev. QEMU otherwise opens the log without O_APPEND and keeps writing at its stale offset after a truncation, punching a sparse hole that leaves the file as large as it was. Measured on QEMU 8.2.2, truncating a 100000-byte log then writing 10 bytes: logappend=off leaves an apparent size of 100010, logappend=on leaves 10. This requirement is the module's contract, documented there, and it holds equally for a supervised process's `OpenOptions::append(true)` stdout — so stdout/stderr rotation is now a call site rather than a reimplementation. The live file is truncated in place, never renamed. The writer holds an open fd on it, so a rename would leave it appending into an unlinked inode and losing every later line without an error. A test pins the inode across rotation. Truncating to zero rather than compacting to a retained buffer is what keeps the log-viewing API working. A follower sees the file shrink and resumes at offset 0, where there is now nothing to re-read. Verified against the `tail` process `tailf` spawns: across a rotation of a 489 KB file a follower received its three trailing lines and then the three new ones, with no duplication. Compacting in place instead replayed the entire retained file to every connected viewer on every rotation. Upgrade safety needs care. The supervisor is a detached daemon and owns the QEMU processes, so restarting VMM leaves running CVMs untouched; after an upgrade those processes are the ones the previous binary launched, without logappend=on. Rotating their logs would punch the hole above, the cap would never hold, and every subsequent tick would rotate again. Eligibility is therefore recorded on the process itself, in the ProcessAnnotation the supervisor already stores: it describes the QEMU that is actually running and survives a VMM restart, and an annotation written by an older VMM has no such key and deserializes to false. Reading the recorded argv would not work, since TPM-backed VMs run through vm-launcher whose argv is only ["vm-launcher", "--spec", <path>]. serial.history.log is removed along with rotate_serial_log, trim_serial_history, serial_history_max_bytes and serial_history_file. The archive existed because the live log was unbounded and QEMU truncated it at every boot; both premises are gone. Dropping the config key is safe because CvmConfig does not deny unknown fields, so a vmm.toml that still sets it keeps loading. Existing serial.history.log files are left on disk: they are bounded, and deleting operator-visible data on upgrade is not this change's job. The log API serves only the live serial.log, so rotated segments are not readable through it and a rotation leaves a reader with an empty file. One line is written into the emptied log saying where the output went, so the absence is self-explanatory. Making ch=serial span segments is left to a follow-up. Rotation is triggered by a periodic stat, so the live log can overshoot the cap by one interval's worth of output. The overshoot only makes one segment larger and is reclaimed on the next tick.
kvinwang
force-pushed
the
codex/fix-vmm-serial-log-cap
branch
from
August 6, 2026 09:19
e4749eb to
e6f9f8d
Compare
kvinwang
added a commit
that referenced
this pull request
Aug 6, 2026
The case tested serial.history.log: that a bounded archive kept exactly one boot delimiter when a single boot overflowed its cap. #970 removes the archive outright. The live logs are now bounded within a boot by rotation, so the previous boot survives as serial.log.1 and boot boundaries land on segment boundaries rather than on delimiters recovered from log text. Every part of the case that named the archive was therefore testing something that no longer exists. Retarget it: - The decision matrix now covers segment retention, the oldest segment being discarded, an empty log not spending a slot, and stdout/stderr rotating alongside serial. - Two properties are called out as observed rather than assumed, because both fail silently: the live file keeps its inode across a rotation (a rename would leave QEMU and the supervisor appending into an unlinked inode), and it is emptied rather than compacted (so a follower resumes instead of replaying). - Step 3 gains the upgrade path: a VM inherited across a VMM restart must not be rotated on the serial channel, because its QEMU was launched without logappend=on. stdout and stderr stay eligible, being the supervisor's and always opened in append mode. The automation stopped scraping DSTACK_SERIAL_ROW markers from the unit tests. Rows are unit-test names now. The markers only existed to feed this case, they made the production tests print for no other reason, and a silently renamed marker read as a pass rather than a failure. Matching on names that must appear in the passing set fails closed instead. The fixture rewrites cvm.log.max_bytes in place rather than appending a key after cvm.use_mrconfigid. cvm.log is a sub-table, so a key appended to the [cvm] scalar block would either sit outside the table or swallow every [cvm] key declared after it. Requires #970. The behaviour under test does not exist before it merges.
kvinwang
added a commit
that referenced
this pull request
Aug 6, 2026
The case tested serial.history.log: that a bounded archive kept exactly one boot delimiter when a single boot overflowed its cap. #970 removes the archive outright. The live logs are now bounded within a boot by rotation, so the previous boot survives as serial.log.1 and boot boundaries land on segment boundaries rather than on delimiters recovered from log text. Every part of the case that named the archive was therefore testing something that no longer exists. Retarget it: - The decision matrix now covers segment retention, the oldest segment being discarded, an empty log not spending a slot, and stdout/stderr rotating alongside serial. - Two properties are called out as observed rather than assumed, because both fail silently: the live file keeps its inode across a rotation (a rename would leave QEMU and the supervisor appending into an unlinked inode), and it is emptied rather than compacted (so a follower resumes instead of replaying). - Step 3 gains the upgrade path: a VM inherited across a VMM restart must not be rotated on the serial channel, because its QEMU was launched without logappend=on. stdout and stderr stay eligible, being the supervisor's and always opened in append mode. The automation stopped scraping DSTACK_SERIAL_ROW markers from the unit tests. Rows are unit-test names now. The markers only existed to feed this case, they made the production tests print for no other reason, and a silently renamed marker read as a pass rather than a failure. Matching on names that must appear in the passing set fails closed instead. The fixture rewrites cvm.log.max_bytes in place rather than appending a key after cvm.use_mrconfigid. cvm.log is a sub-table, so a key appended to the [cvm] scalar block would either sit outside the table or swallow every [cvm] key declared after it. Requires #970. The behaviour under test does not exist before it merges.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Problem
The logs a CVM writes into its work directory are unbounded within a boot. QEMU appends to
serial.logfor the whole life of a boot, and the supervisor appends tostdout.log/stderr.logacross boots without ever clearing them. A chatty or malicious guest can fill the host disk, and the archiving step at the next boot read the whole serial log into memory in one allocation.This PR started from a narrower symptom — serial-log trimming discarded the boot delimiter along with older output — but that symptom only existed because several boots shared one capped archive file and the delimiter had to be recovered from the log text. Bounding a boot removes the condition, so the PR now fixes the cause and the original workaround is deleted.
Why QEMU cannot do this
The QAPI schema for the
fileandptychardev backends exposes onlyout/in/appendplus the genericlogfile/logappend. None is a size limit. The onesizeknob in the chardev family belongs toringbuf, an in-memory ring rather than a file. libvirt hit the same wall and answered it with a separate daemon,virtlogd.Implementation
Rotation lives in a new
logrotatemodule that works on a path and knows nothing about what it is rotating — the same way logrotate(8) does not care.<path>.N-1becomes<path>.N, the live file is archived as<path>.1, and the oldest segment is discarded. A VM start is simply another rotation trigger, so the previous boot is preserved as.1and boot boundaries land on segment boundaries.Three details carry the design.
logappend=onis now passed to the chardev. QEMU otherwise opens the log withoutO_APPENDand keeps writing at its stale offset after a truncation, punching a sparse hole that leaves the file as large as it was. Measured on QEMU 8.2.2, truncating a 100000-byte log then writing 10 bytes:logappend=offlogappend=onThis requirement is the module's documented contract. It holds equally for the supervisor's
OpenOptions::append(true)sinks, which is why stdout/stderr are a call site rather than a second implementation.The live file is truncated in place, never renamed. The writer holds an open fd on it, so a rename would leave it appending into an unlinked inode, losing every later line without an error. A test pins the inode across rotation.
Truncating to zero rather than compacting to a retained buffer is what keeps the log-viewing API working. A follower sees the file shrink and resumes at offset 0, where there is now nothing to re-read. Verified against the
tailprocesstailfspawns: across a rotation of a 489 KB file a follower received its three trailing lines and then the three new ones, with no duplication. Compacting in place instead replayed the entire retained file to every connected viewer on every rotation.All three logs, but not gated alike
stdout.log,stderr.logtry_redirectserial.loglogappend=onThe supervisor already opens its sinks with
append(true)and reopens them when they change — its own comment calls that "logrotate detection" — so those two satisfy the contract regardless of which VMM launched the VM, and keep their cap across a VMM upgrade.serial.logneeds the gate. The supervisor is a detached daemon and owns the QEMU processes, so restarting VMM leaves running CVMs untouched; after an upgrade those processes are the ones the previous binary launched, withoutlogappend=on. Rotating their logs would punch the sparse hole above, the cap would never hold, and every subsequent tick would rotate again. Eligibility is therefore recorded on the process itself, in theProcessAnnotationthe supervisor already stores: it describes the QEMU that is actually running, and an annotation written by an older VMM has no such key and deserializes tofalse. Reading the recorded argv would not work — TPM-backed VMs run throughvm-launcher, whose argv is only["vm-launcher", "--spec", <path>].serial.history.logremovedThe archive existed because the live log was unbounded and QEMU truncated it at every boot. Both premises are gone.
rotate_serial_log,trim_serial_history,serial_history_max_bytesandserial_history_fileare deleted, along with the splice branch that reconstructed a boot delimiter when one boot overflowed the archive cap — segments carry that structure in the filesystem instead, so the guest can no longer confuse a boundary search by printing delimiter-shaped output of its own.Removing the config key is safe:
CvmConfigdoes not deny unknown fields, so a vmm.toml that still sets it keeps loading. Existingserial.history.logfiles are left on disk; they are bounded and harmless.Configuration
Named for the mechanism rather than for serial, because stdout and stderr use the same section. The values live in the shipped vmm.toml rather than in serde defaults, so the defaults are themselves parsed on every load — which is not cosmetic: the doc comment inherited from
serial_history_max_bytesadvertised sizes like"4MB", whichsize_parserdoes not accept. A serde default had been hiding the fact that anyone following that comment would have failed to start the VMM.Behaviour changes to be aware of
stdout.log/stderr.logpreviously accumulated across boots and were never cleared; they are now rotated at each VM start. Reading them still shows the current boot, with earlier boots in.1….N, and the boot separator is still written so a segment read on its own shows where a boot began.Worst-case disk per VM is now 3 logs × (1 +
max_backups) ×max_bytes= 48 MB at the defaults. QEMU's own stdout/stderr are usually tiny and rarely rotate, so the practical figure is far lower.Known limitation
The log API serves only the live file, so rotated segments are not readable through it and a rotation leaves a reader with an empty file. One line is written into the emptied log saying where the output went, so the absence is self-explanatory:
Making
ch=serialspan segments is deliberately left to a follow-up.Rotation is triggered by a periodic stat, so a live log can overshoot the cap by one interval's worth of output. The overshoot only makes one segment larger and is reclaimed on the next tick.
Verification
cargo test -p dstack-vmm --all-features: 105 passed.cargo clippy -p dstack-vmm --all-featuresandcargo fmt --check: clean.tailthattailfspawns.